{
 "cells": [
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "# Profiling ANDES in Notebook"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Profiling with Python CProfiler"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 1,
   "metadata": {},
   "outputs": [],
   "source": [
    "import andes\n",
    "from andes.utils.paths import get_case\n",
    "\n",
    "case_path = get_case('kundur/kundur_full.xlsx')"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Passing `profile=True, no_output = True` to `run` will enable the profiler and have the results printed."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 2,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "Parsing input file </Users/hcui7/repos/andes/cases/kundur/kundur_full.xlsx>\n",
      "Input file kundur_full.xlsx parsed in 0.4787 second.\n",
      "-> Power flow calculation with Newton Raphson method:\n",
      "Power flow initialized.\n",
      "0: |F(x)| = 14.9283   \n",
      "1: |F(x)| = 3.60859   \n",
      "2: |F(x)| = 0.170093  \n",
      "3: |F(x)| = 0.00203827\n",
      "4: |F(x)| = 3.76414e-07\n",
      "Converged in 5 iterations in 0.0160 second.\n",
      "-> Time Domain Simulation:\n",
      "Initialization tests passed.\n",
      "Initialization successful in 0.0305 second.\n",
      "  0%|                                          | 0/100 [00:00<?, ?%/s]<Toggle 0>: Applying status toggle on Line idx=Line_8\n",
      "100%|███████████████████████████████| 100/100 [00:00<00:00, 145.64%/s]\n",
      "Simulation completed in 0.6874 second.\n",
      "\n",
      "-> Single process finished in 1.6296 seconds.\n"
     ]
    },
    {
     "name": "stdout",
     "output_type": "stream",
     "text": [
      "         745620 function calls (737170 primitive calls) in 1.566 seconds\n",
      "\n",
      "   Ordered by: cumulative time\n",
      "   List reduced from 3287 to 40 due to restriction <40>\n",
      "\n",
      "   ncalls  tottime  percall  cumtime  percall filename:lineno(function)\n",
      "        1    0.000    0.000    0.797    0.797 /Users/hcui7/repos/andes/andes/main.py:218(load)\n",
      "        1    0.001    0.001    0.748    0.748 /Users/hcui7/repos/andes/andes/routines/tds.py:85(run)\n",
      "   555/38    0.003    0.000    0.701    0.018 <frozen importlib._bootstrap>:978(_find_and_load)\n",
      "   547/31    0.002    0.000    0.700    0.023 <frozen importlib._bootstrap>:948(_find_and_load_unlocked)\n",
      "   518/22    0.003    0.000    0.692    0.031 <frozen importlib._bootstrap>:663(_load_unlocked)\n",
      "   427/22    0.002    0.000    0.691    0.031 <frozen importlib._bootstrap_external>:722(exec_module)\n",
      "   456/23    0.003    0.000    0.680    0.030 {built-in method builtins.exec}\n",
      "   707/22    0.000    0.000    0.678    0.031 <frozen importlib._bootstrap>:211(_call_with_frames_removed)\n",
      "      132    0.025    0.000    0.677    0.005 /Users/hcui7/repos/andes/andes/routines/tds.py:163(_implicit_step)\n",
      "        1    0.000    0.000    0.480    0.480 /Users/hcui7/repos/andes/andes/io/__init__.py:81(parse)\n",
      "        1    0.000    0.000    0.478    0.478 /Users/hcui7/repos/andes/andes/io/xlsx.py:60(read)\n",
      "     2647    0.019    0.000    0.455    0.000 /Users/hcui7/repos/andes/andes/system.py:557(_call_models_method)\n",
      "        2    0.000    0.000    0.381    0.190 /Users/hcui7/repos/andes/andes/utils/lazyimport.py:73(__getattr__)\n",
      "        2    0.000    0.000    0.380    0.190 /Users/hcui7/repos/andes/andes/utils/lazyimport.py:61(__maybe_import__)\n",
      "        1    0.000    0.000    0.378    0.378 /Users/hcui7/miniconda3/envs/a/lib/python3.7/site-packages/pandas/__init__.py:3(<module>)\n",
      "      427    0.006    0.000    0.333    0.001 <frozen importlib._bootstrap_external>:793(get_code)\n",
      "        1    0.000    0.000    0.292    0.292 /Users/hcui7/repos/andes/andes/system.py:37(__init__)\n",
      "   125/81    0.000    0.000    0.288    0.004 {built-in method builtins.__import__}\n",
      "       24    0.000    0.000    0.287    0.012 /Users/hcui7/miniconda3/envs/a/lib/python3.7/importlib/__init__.py:109(import_module)\n",
      "       24    0.000    0.000    0.286    0.012 <frozen importlib._bootstrap>:994(_gcd_import)\n",
      "        1    0.000    0.000    0.268    0.268 /Users/hcui7/repos/andes/andes/system.py:685(_routine_import)\n",
      "      427    0.099    0.000    0.245    0.001 <frozen importlib._bootstrap_external>:914(get_data)\n",
      "      438    0.000    0.000    0.219    0.001 /Users/hcui7/repos/andes/andes/system.py:357(g_update)\n",
      "     6097    0.107    0.000    0.213    0.000 /Users/hcui7/repos/andes/andes/core/model.py:1015(g_update)\n",
      "        1    0.000    0.000    0.211    0.211 /Users/hcui7/miniconda3/envs/a/lib/python3.7/site-packages/pandas/core/api.py:3(<module>)\n",
      "3803/3401    0.002    0.000    0.182    0.000 <frozen importlib._bootstrap>:1009(_handle_fromlist)\n",
      "        1    0.000    0.000    0.181    0.181 /Users/hcui7/repos/andes/andes/routines/pflow.py:1(<module>)\n",
      "        1    0.000    0.000    0.180    0.180 /Users/hcui7/repos/andes/andes/routines/base.py:1(<module>)\n",
      "        1    0.000    0.000    0.180    0.180 /Users/hcui7/repos/andes/andes/core/solver.py:1(<module>)\n",
      "      427    0.147    0.000    0.147    0.000 {method 'read' of '_io.FileIO' objects}\n",
      "      438    0.000    0.000    0.128    0.000 /Users/hcui7/repos/andes/andes/system.py:354(f_update)\n",
      "     6097    0.083    0.000    0.122    0.000 /Users/hcui7/repos/andes/andes/core/model.py:985(f_update)\n",
      "        1    0.000    0.000    0.113    0.113 /Users/hcui7/miniconda3/envs/a/lib/python3.7/site-packages/pandas/core/groupby/__init__.py:1(<module>)\n",
      "        1    0.000    0.000    0.112    0.112 /Users/hcui7/miniconda3/envs/a/lib/python3.7/site-packages/pandas/core/groupby/generic.py:7(<module>)\n",
      "      518    0.001    0.000    0.105    0.000 <frozen importlib._bootstrap>:576(module_from_spec)\n",
      "        1    0.000    0.000    0.098    0.098 /Users/hcui7/miniconda3/envs/a/lib/python3.7/site-packages/pandas/core/frame.py:10(<module>)\n",
      "      543    0.004    0.000    0.094    0.000 <frozen importlib._bootstrap>:882(_find_spec)\n",
      "       91    0.000    0.000    0.092    0.001 <frozen importlib._bootstrap_external>:1040(create_module)\n",
      "       91    0.091    0.001    0.091    0.001 {built-in method _imp.create_dynamic}\n",
      "      544    0.001    0.000    0.088    0.000 <frozen importlib._bootstrap_external>:1272(find_spec)\n",
      "\n",
      "\n"
     ]
    }
   ],
   "source": [
    "ss = andes.run(case_path, profile=True, routine='TDS', no_output=True)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "## Profiling with `line_profiler`."
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "`line_profiler` provides line-based profiling results for functions. \n",
    "\n",
    "Install with `pip install line_profiler` and restart the notebook."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 3,
   "metadata": {},
   "outputs": [],
   "source": [
    "import andes\n",
    "from andes.utils.paths import get_case\n",
    "\n",
    "case_path = get_case('kundur/kundur_full.xlsx')"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Profile power flow "
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Pass the function name to profile to the magic `%lprun`, followed by a call to the function itself or an upper-level function.\n",
    "\n",
    "Results will be shown in a popup window."
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 4,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "Parsing input file </Users/hcui7/repos/andes/cases/kundur/kundur_full.xlsx>\n",
      "Input file kundur_full.xlsx parsed in 0.1227 second.\n",
      "-> Power flow calculation with Newton Raphson method:\n",
      "Power flow initialized.\n",
      "0: |F(x)| = 14.9283   \n",
      "1: |F(x)| = 3.60859   \n",
      "2: |F(x)| = 0.170093  \n",
      "3: |F(x)| = 0.00203827\n",
      "4: |F(x)| = 3.76414e-07\n",
      "Converged in 5 iterations in 0.0159 second.\n",
      "-> Single process finished in 0.1867 second.\n"
     ]
    }
   ],
   "source": [
    "%lprun -f andes.routines.pflow.PFlow.run andes.run(case_path, no_output=True)"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "Alternatively, do"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 5,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "Parsing input file </Users/hcui7/repos/andes/cases/kundur/kundur_full.xlsx>\n",
      "Input file kundur_full.xlsx parsed in 0.0671 second.\n",
      "-> Power flow calculation with Newton Raphson method:\n",
      "Power flow initialized.\n",
      "0: |F(x)| = 14.9283   \n",
      "1: |F(x)| = 3.60859   \n",
      "2: |F(x)| = 0.170093  \n",
      "3: |F(x)| = 0.00203827\n",
      "4: |F(x)| = 3.76414e-07\n",
      "Converged in 5 iterations in 0.0163 second.\n",
      "-> Single process finished in 0.1140 second.\n"
     ]
    }
   ],
   "source": [
    "ss = andes.run(case_path, no_output=True)"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 6,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "-> Power flow calculation with Newton Raphson method:\n",
      "Power flow initialized.\n",
      "0: |F(x)| = 14.9283   \n",
      "1: |F(x)| = 3.60859   \n",
      "2: |F(x)| = 0.170093  \n",
      "3: |F(x)| = 0.00203827\n",
      "4: |F(x)| = 3.76414e-07\n",
      "Converged in 5 iterations in 0.0167 second.\n"
     ]
    }
   ],
   "source": [
    "%lprun -f ss.PFlow.run ss.PFlow.run()"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "To dig into the Newton Raphson iteration steps, profile each step instead with:"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 7,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "-> Power flow calculation with Newton Raphson method:\n",
      "Power flow initialized.\n",
      "0: |F(x)| = 14.9283   \n",
      "1: |F(x)| = 3.60859   \n",
      "2: |F(x)| = 0.170093  \n",
      "3: |F(x)| = 0.00203827\n",
      "4: |F(x)| = 3.76414e-07\n",
      "Converged in 5 iterations in 0.0162 second.\n"
     ]
    }
   ],
   "source": [
    "%lprun -f ss.PFlow.nr_step ss.PFlow.run()"
   ]
  },
  {
   "cell_type": "markdown",
   "metadata": {},
   "source": [
    "### Profile time-domain simulation"
   ]
  },
  {
   "cell_type": "code",
   "execution_count": 8,
   "metadata": {},
   "outputs": [
    {
     "name": "stderr",
     "output_type": "stream",
     "text": [
      "-> Time Domain Simulation:\n",
      "Initialization tests passed.\n",
      "Initialization successful in 0.0289 second.\n",
      "  0%|                                          | 0/100 [00:00<?, ?%/s]<Toggle 0>: Applying status toggle on Line idx=Line_8\n",
      "100%|███████████████████████████████| 100/100 [00:00<00:00, 127.97%/s]\n",
      "Simulation completed in 0.7819 second.\n"
     ]
    }
   ],
   "source": [
    "%lprun -f ss.TDS._implicit_step ss.TDS.run()"
   ]
  }
 ],
 "metadata": {
  "kernelspec": {
   "display_name": "Python 3",
   "language": "python",
   "name": "python3"
  },
  "language_info": {
   "codemirror_mode": {
    "name": "ipython",
    "version": 3
   },
   "file_extension": ".py",
   "mimetype": "text/x-python",
   "name": "python",
   "nbconvert_exporter": "python",
   "pygments_lexer": "ipython3",
   "version": "3.7.6"
  }
 },
 "nbformat": 4,
 "nbformat_minor": 4
}
